
from IPython.display import display, HTML
display(HTML("<style>.container {width:100% !important; }</style>"))

import glob
import pandas as pd
import numpy as np
import hvplot.pandas
import plotly.express as px
import plotly.graph_objects as go
pd.options.mode.chained_assignment = None

import datetime as dt
%autosave 30

Autosaving every 30 seconds


CPU_FREQ=2.60

rdtsc_df_dict = []
ttt_df_dict = []
for filename in glob.glob("exchange*.log") + glob.glob("*_1.log"):
    print('processing {}'.format(filename))
    for line in open(filename):
        tokens = line.strip().split(' ')
        if len(tokens) != 4:
            continue

        try:
            time = tokens[0]
            tag = tokens[2]
            latency = float(tokens[3])
            latency_rdtsc = latency / CPU_FREQ
            time_datetime = pd.to_datetime(time, format='%H:%M:%S.%f')
        except:
            continue

        if ' RDTSC ' in line:
            if tokens[1] != 'RDTSC':
                continue

            rdtsc_df_dict.append({'timestamp':time, 'tag':tag, 'latency':latency_rdtsc})
        elif ' TTT ' in line:
            if tokens[1] != 'TTT':
                continue

            ttt_df_dict.append({'timestamp':time, 'tag':tag, 'latency':latency})
        
rdtsc_df = pd.DataFrame.from_dict(rdtsc_df_dict)
rdtsc_df = rdtsc_df.drop_duplicates().sort_values(by='timestamp')
rdtsc_df['timestamp'] = pd.to_datetime(rdtsc_df['timestamp'], format='%H:%M:%S.%f')

ttt_df = pd.DataFrame.from_dict(ttt_df_dict)
ttt_df = ttt_df.drop_duplicates().sort_values(by='timestamp')
ttt_df['timestamp'] = pd.to_datetime(ttt_df['timestamp'], format='%H:%M:%S.%f')

processing exchange_snapshot_synthesizer.log
processing exchange_order_server.log
processing exchange_main.log
processing exchange_matching_engine.log
processing exchange_market_data_publisher.log
processing trading_main_1.log
processing trading_order_gateway_1.log
processing trading_engine_1.log
processing trading_market_data_consumer_1.log


for tag in rdtsc_df['tag'].unique():
    print(tag)
    
    fig = go.Figure()

    t_df = rdtsc_df[rdtsc_df['tag'] == tag].copy()
    t_df = t_df[t_df['latency'] > 0]

    q_hi = t_df['latency'].quantile(0.99)
    q_lo = t_df['latency'].quantile(0.01)
    t_df = t_df[(t_df['latency'] < q_hi) & (t_df['latency'] > q_lo)]

    mean = t_df['latency'].astype(float).mean()
    print('{} has {} observations mean {}'.format(tag, len(t_df), mean))

    rolling_window = max(1, int(len(t_df) / 100))

    use_micros = False
    if mean >= 1000:
        use_micros = True
        t_df['latency'] = t_df['latency'].astype(float) / 1000

    fig.add_trace(go.Scatter(x=t_df['timestamp'], y=t_df['latency'], name=tag))
    fig.add_trace(go.Scatter(x=t_df['timestamp'], y=t_df['latency'].rolling(rolling_window).mean(), name=tag + ' mean'))
#     fig.add_trace(go.Scatter(x=t_df['timestamp'], y=t_df['latency'].rolling(rolling_window).std(), name=tag + ' std'))

    fig.update_layout(title='performance ' + tag + ' ' + ('microseconds' if use_micros else 'nanoseconds'), height=750, width=1000, hovermode='x', legend=dict(
        yanchor="top",
        y=0.99,
        xanchor="left",
        x=0.01
    ))
    fig.show()

Exchange_FIFOSequencer_addClientRequest
Exchange_FIFOSequencer_addClientRequest has 10487 observations mean 82.03394679126538

Exchange_FIFOSequencer_sequenceAndPublish
Exchange_FIFOSequencer_sequenceAndPublish has 10374 observations mean 53909.935971585764

Exchange_MEOrderBook_checkForMatch
Exchange_MEOrderBook_checkForMatch has 5703 observations mean 163383.84224227464

Exchange_MEOrderBook_addOrder
Exchange_MEOrderBook_addOrder has 3636 observations mean 497.1089320470508

Exchange_MEOrderBook_add
Exchange_MEOrderBook_add has 5708 observations mean 337468.20750902913

Exchange_MatchingEngine_processClientRequest
Exchange_MatchingEngine_processClientRequest has 11326 observations mean 254875.95264130185

Exchange_MEOrderBook_removeOrder
Exchange_MEOrderBook_removeOrder has 2969 observations mean 1281.9594787159622

Exchange_MEOrderBook_cancel
Exchange_MEOrderBook_cancel has 5616 observations mean 56774.474989042305

Exchange_McastSocket_send
Exchange_McastSocket_send has 12158 observations mean 433.9329279866374

Exchange_TCPSocket_send
Exchange_TCPSocket_send has 18355 observations mean 185.35437839197033


HOPS = [
    ['T1_OrderServer_TCP_read', 'T2_OrderServer_LFQueue_write'],
    ['T2_OrderServer_LFQueue_write', 'T3_MatchingEngine_LFQueue_read'],
    ['T3_MatchingEngine_LFQueue_read', 'T4_MatchingEngine_LFQueue_write'], ['T3_MatchingEngine_LFQueue_read', 'T4t_MatchingEngine_LFQueue_write'],
    ['T4_MatchingEngine_LFQueue_write', 'T5_MarketDataPublisher_LFQueue_read'], ['T4t_MatchingEngine_LFQueue_write', 'T5t_OrderServer_LFQueue_read'],
    ['T5_MarketDataPublisher_LFQueue_read', 'T6_MarketDataPublisher_UDP_write'], ['T5t_OrderServer_LFQueue_read', 'T6t_OrderServer_TCP_write'],
    ['T7_MarketDataConsumer_UDP_read', 'T8_MarketDataConsumer_LFQueue_write'], ['T7t_OrderGateway_TCP_read', 'T8t_OrderGateway_LFQueue_write'],
    ['T8_MarketDataConsumer_LFQueue_write', 'T9_TradeEngine_LFQueue_read'], ['T8t_OrderGateway_LFQueue_write', 'T9t_TradeEngine_LFQueue_read'],
    ['T9_TradeEngine_LFQueue_read', 'T10_TradeEngine_LFQueue_write'], ['T9t_TradeEngine_LFQueue_read', 'T10_TradeEngine_LFQueue_write'],
    ['T10_TradeEngine_LFQueue_write', 'T11_OrderGateway_LFQueue_read'],
    ['T11_OrderGateway_LFQueue_read', 'T12_OrderGateway_TCP_write'],
    # exchange <-> client
    ['T12_OrderGateway_TCP_write', 'T1_OrderServer_TCP_read'],
    ['T6_MarketDataPublisher_UDP_write', 'T7_MarketDataConsumer_UDP_read'], ['T6t_OrderServer_TCP_write', 'T7t_OrderGateway_TCP_read'],
]


for tags in HOPS:
    tag_p, tag_n = tags
    print('{} => {}. {} => {}.'.format(tag_p, len(ttt_df[ttt_df['tag'] == tag_p]), tag_n, len(ttt_df[ttt_df['tag'] == tag_n])))

    fig = go.Figure()

    t_df = ttt_df[(ttt_df['tag'] == tag_n) | (ttt_df['tag'] == tag_p)]
    t_df['latency_diff'] = t_df['latency'].diff()
    t_df = t_df[t_df['latency_diff'] > 0]
    t_df = t_df[t_df.tag == tag_n]

    q_hi = t_df['latency_diff'].quantile(0.99)
    q_lo = t_df['latency_diff'].quantile(0.01)
    t_df = t_df[(t_df['latency_diff'] < q_hi) & (t_df['latency_diff'] > q_lo)]

    mean = t_df['latency_diff'].astype(float).mean()
    print('{} has {} observations mean {}'.format(tag_n, len(t_df), mean))

    rolling_window = max(1, int(len(t_df) / 100))

    unit = 'nanoseconds'
    if mean >= 1000000:
        unit = 'milliseconds'
        t_df['latency_diff'] = t_df['latency_diff'].astype(float) / 1000000
    elif mean >= 1000:
        unit = 'microseconds'
        t_df['latency_diff'] = t_df['latency_diff'].astype(float) / 1000

    tag_name = tag_p + ' -> ' + tag_n
    fig.add_trace(go.Scatter(x=t_df['timestamp'], y=t_df['latency_diff'], name=tag_name))
    fig.add_trace(go.Scatter(x=t_df['timestamp'], y=t_df['latency_diff'].rolling(rolling_window).mean(), name=tag_name + ' mean'))

    fig.update_layout(title='performance ' + tag_name + ' ' + unit, height=750, width=1000, hovermode='x', legend=dict(
        yanchor="top",
        y=0.99,
        xanchor="left",
        x=0.01
    ))
    fig.show()

T1_OrderServer_TCP_read => 10870. T2_OrderServer_LFQueue_write => 11558.
T2_OrderServer_LFQueue_write has 11306 observations mean 131404.89509994694

T2_OrderServer_LFQueue_write => 11558. T3_MatchingEngine_LFQueue_read => 11558.
T3_MatchingEngine_LFQueue_read has 10784 observations mean 3189226.278931751

T3_MatchingEngine_LFQueue_read => 11558. T4_MatchingEngine_LFQueue_write => 12447.
T4_MatchingEngine_LFQueue_write has 12175 observations mean 344765.1561396304

T3_MatchingEngine_LFQueue_read => 11558. T4t_MatchingEngine_LFQueue_write => 18802.
T4t_MatchingEngine_LFQueue_write has 18406 observations mean 259917.150494404

T4_MatchingEngine_LFQueue_write => 12447. T5_MarketDataPublisher_LFQueue_read => 12447.
T5_MarketDataPublisher_LFQueue_read has 12066 observations mean 1910351.753356539

T4t_MatchingEngine_LFQueue_write => 18802. T5t_OrderServer_LFQueue_read => 18802.
T5t_OrderServer_LFQueue_read has 18290 observations mean 1908845.1604155276

T5_MarketDataPublisher_LFQueue_read => 12447. T6_MarketDataPublisher_UDP_write => 12447.
T6_MarketDataPublisher_UDP_write has 12188 observations mean 317922.17394158186

T5t_OrderServer_LFQueue_read => 18802. T6t_OrderServer_TCP_write => 18802.
T6t_OrderServer_TCP_write has 18342 observations mean 273255.22625667864


import session_info
session_info.show()